dtrace on macOS

2023-01-30 · 1 min read

setup: disable system integrity protection for dtrace #

By default, macOS won't let you run dtrace, even when run as root. Fortunately we can can carve out a specific exception for dtrace. To do that we'll have to boot into recovery mode:

  1. Turn off the computer.
  2. Hold down the power button for ~10 sec, until a screen pops up with two options.
  3. Select "Options" to boot into recovery mode.
  4. Ignore the initial screen and instead select "Terminal" from the top bar.
  5. Run csrutil enable --without dtrace.
  6. Reboot normally.

Once you're booted back in, try running sudo dtruss bash -c echo foo and you should see some output.

syscall counts of running process #

$ sudo dtrace -n 'syscall:::entry/pid == 1234/{ @syscalls[probefunc] = count(); }'

# .. collect data, then hit CTRL-C .. #
^C

chmod                                                             3
close                                                             3
fchown                                                            3
rename                                                            3
getuid                                                            5
lstat64                                                           6
# ..
fcntl                                                           105
open_nocancel                                                   313
fcntl_nocancel                                                  322
fstat64                                                         322
close_nocancel                                                  391
read                                                            465
write                                                           480
stat64                                                          685
kevent                                                         1333

trace bytes read by all processes #

$ sudo dtrace -n "syscall::read:entry { @bytes[execname] = sum(arg2); }"
dtrace: description 'syscall::read:entry ' matched 1 probe
^C

sudo                                                              2
plugin-container                                                 10
karabiner_observer                                             4096
tmux                                                           4096
karabiner_console_user_server                                  8192
karabiner_session_monitor                                      9216
cfprefsd                                                      17665
firefox                                                       32787
git                                                           33225
karabiner_grabber                                             38912
Karabiner-DriverKit-VirtualHIDDe                              51200
postgres                                                      57397
locationd                                                     57680
sharingd                                                      57680
Obsidian Helper (Renderer)                                   399360
mds                                                         1326816
fseventsd                                                   1777432
alacritty                                                   4194560
mdworker_shared                                             5242880

trace spawned processes #

$ sudo dtrace -qn "syscall::posix_spawn:entry { printf(\"%Y %s\n\", walltimestamp, copyinstr(arg1)); }"

^[2023 Jan 30 13:29:50 /usr/bin/git
2023 Jan 30 13:29:50 /usr/bin/git
2023 Jan 30 13:29:52 /usr/libexec/xpcproxy
2023 Jan 30 13:29:52 /opt/homebrew/opt/postgresql@14/bin/postgres
2023 Jan 30 13:29:55 /usr/libexec/xpcproxy
2023 Jan 30 13:29:55 /System/Library/Frameworks/CoreServices.framework/Frameworks/Metadata.framework/Versions/A/Support/mdworker_shared
2023 Jan 30 13:30:02 /usr/libexec/xpcproxy
2023 Jan 30 13:30:02 /opt/homebrew/opt/postgresql@14/bin/postgres
2023 Jan 30 13:30:05 /usr/libexec/xpcproxy
2023 Jan 30 13:30:05 /usr/sbin/newsyslog
2023 Jan 30 13:30:12 /usr/libexec/xpcproxy
2023 Jan 30 13:30:12 /opt/homebrew/opt/postgresql@14/bin/postgres

Find longest syscalls #

$ sudo dtrace -qn \
	'syscall:::entry { self->ts = timestamp; } syscall:::return/self->ts/ { printf("%d µs, %s\n", (timestamp - self->ts) / 1000, probefunc); self->ts = 0; }' \
    -c 'bash -c "python3 -c \"print(123)\""' \
	| sort -h

..
42 µs, ioctl
44 µs, open_nocancel
44 µs, shared_region_check_np
351 µs, execve
943 µs, ioctl
1279 µs, workq_kernreturn
1348 µs, psynch_cvwait

some oneliners #

# Files opened by process. Very useful when reversing:
dtrace -n 'syscall::open*:entry { printf("%s %s", execname, copyinstr(arg0)); }'

# Syscall count by program:
dtrace -n 'syscall:::entry { @num[execname] = count(); }'

# Syscall count by syscall:
dtrace -n 'syscall:::entry { @num[probefunc] = count(); }'

# Syscall count by PID:
dtrace -n 'syscall:::entry { @num[pid,execname] = count(); }'

# Read bytes by process:
dtrace -n 'syscall::read:entry { @bytes[execname] = sum(arg0); }'

# Periodic breakdown of written bytes by process:
dtrace -n 'syscall::write:* { @bytes[execname] = sum(arg0); } tick-5sec { printa(@bytes); trunc(@bytes); }'

# Read size distribution by process:
dtrace -n 'syscall::read:entry { @dist[execname] = quantize(arg0); }'

# Write size distribution by process:
dtrace -n 'syscall::write:entry { @dist[execname] = quantize(arg0); }'

# Disk size (in blocks) by process:
dtrace -n 'io:::start { printf("%d %s %d", pid, execname, args[0]->b_bcount); }'

# Pages paged in by process:
dtrace -n 'vminfo::vm_fault_enter:pgin { @pg[execname] = sum(arg0); }'

# Minor faults by process:
dtrace -n 'vminfo:::as_fault { @mem[execname] = sum(arg0); }'

# Interrupts by CPU:
dtrace -n 'sdt:::interrupt-start { @num[cpu] = count(); }'

# New processes with arguments and time:
dtrace -qn 'syscall::exec*:return { printf("%Y %s\n",walltimestamp,curpsinfo->pr_psargs); }'

# Successful signal details:
dtrace -n 'proc:::signal-send /pid/ { printf("%s -%d %d",execname,args[2],args[1]->pr_pid); }'

# System call breakdown for the process with PID 31337:
dtrace -n syscall:::entry'/pid == 31337/{ @syscalls[probefunc] = count(); }'

# Tracking memory page faults for process:
dtrace -n 'vminfo:::as_fault { @mem[execname] = sum(arg0); }'

# iOS Intruments-like malloc size distribution plot:
dtrace -n 'pid$target::malloc:entry { @ = quantize(arg0); }' -p PID

# Memory allocation via malloc by stack trace and requested size:
dtrace -n 'pid$target::malloc:entry { @[ustack()] = sum(arg0); }' -p PID

# Rate of disk I/O:
dtrace -n 'io:::start { @io = count(); } tick-1sec { printa("Disk I/Os per second: %@d\n", @io); trunc(@io); }'

trace spawned processes w/ full arguments #

// file: /usr/local/bin/traceexec.d

#!/usr/sbin/dtrace -C -s
#pragma D option quiet

dtrace:::BEGIN 
{
    printf("PID\tPPID\tTIME\tPATH\tARGV\n")
}

// remember that probes are executed _in the order they appear in the file_
// and that probe-local variables (this->XXX) are shared across activated
// probes.

// Since `arg0` and `argv[idx]` are in user-space and probes are run in
// kernel-space, we have to first `copyin[str](..)` the user-space strings
// before we can process them.

syscall::execve:entry
/pid == $target || progenyof($target)/
{
    this->path = copyinstr(arg0);
    this->argv = args[1];
}

syscall::posix_spawn:entry
/pid == $target || progenyof($target)/
{
    this->path = copyinstr(arg1);
    this->argv = args[3];
}

#define SAFE_ARGC(idx) ((this->argc != (idx) || this->argv[(idx)] == NULL) ? this->argc : (this->argc + 1))
#define SAFE_ARGV(idx) ((this->argc > (idx)) ? copyinstr((user_addr_t) this->argv[(idx)]) : "")

syscall::execve:entry,
syscall::posix_spawn:entry
/pid == $target || progenyof($target)/
{
    this->pid=pid;
    this->ppid=ppid;

    // DTrace doesn't support loops, so we have to manually unroll the argc
    // and argv processing.

    this->argc = 0;
    this->argc = SAFE_ARGC(0);
    this->argc = SAFE_ARGC(1);
    this->argc = SAFE_ARGC(2);
    this->argc = SAFE_ARGC(3);
    this->argc = SAFE_ARGC(4);
    this->argc = SAFE_ARGC(5);
    this->argc = SAFE_ARGC(6);
    this->argc = SAFE_ARGC(7);
    this->argc = SAFE_ARGC(8);
    this->argc = SAFE_ARGC(9);
    
    printf("%d\t", pid);
    printf("%d\t", ppid);
    printf("%Y\t", walltimestamp);
    printf("%s\t", this->path);
    printf("%s ", SAFE_ARGV(1));
    printf("%s ", SAFE_ARGV(2));
    printf("%s ", SAFE_ARGV(3));
    printf("%s ", SAFE_ARGV(4));
    printf("%s ", SAFE_ARGV(5));
    printf("%s ", SAFE_ARGV(6));
    printf("%s ", SAFE_ARGV(7));
    printf("%s ", SAFE_ARGV(8));
    printf("%s ", SAFE_ARGV(9));
    printf("\n");
}

#undef SAFE_ARGC
#undef SAFE_ARGV

reference #

Oracle - Dynamic Tracing Guide (pdf)